[TRTLLM-6904][feat] add timing metrics for input processing and multimodal encoding - #20739

Description

Expose server input preparation and multimodal encoder timing through Prometheus, with CPU input timings retained in existing request JSONL and opt-in Server-Timing / SSE output.

• Measure total input preparation through synchronous preprocessing and request submission, excluding the wait for generation.
• Separate media resolution, chat rendering, processor execution/queue, and per-item HTTP download/decode/queue by modality.
• Exclude health-generation probes from input histograms and shared HTTP session setup from download timing. Anthropic Messages total starts in the delegated chat handler. Encoder-only serving exposes the same Prometheus and completed-request timing paths; process-pool media loading retains picklable submissions.
• Preserve input timings across context/generation handoff. HTTP requests and background Message Batch items use separate contexts and completed-request records.
• Reuse CUDA events and iteration statistics for rank-0 encoder call/batch timing without adding GPU synchronization or collectives.

Use existing return_perf_metrics, enable_iter_perf_stats and perf_metrics_output_dir options. Stages can overlap; their averages are not additive. Encoder GPU time remains a batch measurement.

Test Coverage

• CodeRabbit follow-up f51b20d448: 54 serving/media CPU tests passed with current serving/media modules in a release runtime. Three regressions reproduced before the fix: process-pool serialization, the encoder-only Prometheus endpoint and request timing export. 5 isolated callback-gate cases passed using the current method in the release executor class; full rebased executor/GPU validation still requires matching native binaries. Pre-commit passed.
• Rebased 09b94b583d onto main b752bf4691; preserved main's request validation, NCCL window lifetime handling and asynchronous metrics collection. Pre-commit passed.
• The earlier 41-test media/request subset is included in the current CPU run. Full-source/GPU validation was not rerun: the available native build predates main's NCCL window operators.
• Reuse the existing cache-hit test to check encoder timing hooks; its cpu_only mark enables that coverage in L0 CPU CI.
• Earlier whole-PR validation: 568 CPU tests passed; 22 tokenizer-dependent cases skipped on e55226305b after rebase onto main af3e5eb257; pre-commit passed. Metric regressions are registered in CPU CI.
• Prior serving/export validation (d595f0159f), H200 / Qwen3-VL-8B-Instruct-FP8: HTTP download, inline/multiple images, streaming, text-only, Responses and mixed Message Batch requests; Prometheus, request JSONL and response timing values matched where available. AIPerf exported all four histogram families.

Instrumentation overhead

return_perf_metrics=False, enable_iter_perf_stats=False and no JSONL output directory are the defaults. ON below enables both existing statistics flags, so ON/OFF includes existing collection costs as well as the new timers.

Base af3e5eb257 vs PR e55226305b: AIPerf 0.8.0, Qwen3-VL-8B-Instruct-FP8, TP1 on one H200 NVL. Fixed max batch 64, max tokens/sequence 8192, decoder CUDA graphs [1,2,4,8,16,32,64], and no KV/encoder reuse. JSONL, requested response timing and profiling-time metrics scraping were disabled.

Long image-concurrency-64 validation: 65,536/65,536 successful measured requests, all 16 output tokens. Two balanced repeats per condition, 8,192 measured requests and 512 excluded warmups per repeat. Client and server used separate CPU affinities.

Base → PR OFF: +3.60 ms TTFT (+1.69%), -1.38% req/s. With both ON: +15.23 ms TTFT (+6.90%), +4.13% mean req/s. The ON throughput comparison changed sign between repeats; the earlier short C64 decrease did not reproduce consistently. These results do not establish zero overhead or an incremental throughput gain.

The initial text/image concurrency 1/8/64/128 screen completed another 26,624 successful requests. Image C1 PR OFF → ON TTFT was 70.22 → 72.37 ms (+2.14 ms, +3.05%); C128 was 867.10 → 886.15 ms (+19.06 ms, +2.20%). Text C64 ON throughput was 191.56 → 191.16 req/s (-0.21%) from base to PR, despite a larger total ON/OFF statistics cost. JSONL/SSE export overhead was not measured.

PR Checklist

• Reviewed coding guidelines, tests, documentation, DCO sign-off and backward-compatible API labeling. No new dependencies or configuration fields.

Dev Engineer Review

The change adds request-scoped input-processing timings, Prometheus histograms for input stages and media work, JSONL and Server-Timing export, and encoder GPU-time reporting. The timing context covers preprocessing and request submission, not generation wait. The instrumentation also covers encoder-only serving and background batch requests.

The implementation adds executor-aware media timing and avoids timing decode work in process pools. Encoder timings use CUDA events and iteration statistics without extra GPU synchronization or collectives. Stage averages can overlap, and encoder GPU time is a batch measurement; consumers must not treat these values as exclusive request latency.

The main verification risk is the unvalidated GPU and executor path: the author reports that full rebased executor/GPU validation was not run because matching native binaries were unavailable. The author reports passing CPU and callback-gate tests, but JSONL/SSE export overhead was not measured. The reported performance results varied between repeats when statistics were enabled.

QA Engineer Review

Changed tests cover request and media timing, failure paths, request isolation, context and JSONL/header export, encoder callback gates and CUDA-event collection, rank fanout, and legacy stats serialization. The CPU CI list adds targeted media cases, the OpenAI input-metrics test file, and selected request-metrics cases. No manual-QA list registration is shown.

Coverage verdict: needs follow-up. The reported CPU coverage is useful, but full GPU/executor validation and export-overhead measurement remain outstanding.

Per-File QA Perspective

• docs/source/features/multi-modality.md — Documents serving options, histogram scopes, exports, limitations, and a scraping example. Verify the documented names and timing boundaries match the implementation.
• tensorrt_llm/_torch/models/modeling_multimodal_mixin.py — Routes encoder paths through an optional context hook. Verify full-batch, scheduled, partial-cache, and prefetch paths preserve behavior with and without the hook.
• tensorrt_llm/_torch/pyexecutor/perf_metrics_manager.py — Adds non-blocking CUDA-event timing collection and event reuse. Verify pending, failed, and completed event paths on supported GPU execution.
• tensorrt_llm/_torch/pyexecutor/py_executor.py — Installs encoder timing conditionally and adds samples to iteration statistics. Verify callback gates, rank-0 behavior, and attention-DP fanout.
• tensorrt_llm/executor/base_worker.py — Serializes optional encoder timing while retaining compatibility with older stats tuples. Verify both tuple shapes.
• tensorrt_llm/inputs/media_io.py — Adds download, decode-queue, and decode timing by modality, with special handling for process pools. Verify HTTP, data, and file inputs and decode failures.
• tensorrt_llm/inputs/utils.py — Times media retrieval and threaded chat-template rendering; returns early when no media data is pending. Verify empty and populated retrieval paths.
• tensorrt_llm/metrics/collector.py — Adds input-stage, processor-queue, media, and encoder histograms. Verify stage classification, modality labels, and milliseconds-to-seconds conversion.
• tensorrt_llm/metrics/perf_utils.py — Adds context-local timing helpers that record in finally when an observer exists. Verify exception handling and disabled-observer behavior.
• tensorrt_llm/serve/_perf_metrics_schema.py — Adds optional input_processing_metrics to PerfMetrics. Verify compatibility with records that omit the field.
• tensorrt_llm/serve/openai_server.py — Instruments request preprocessing and submission across several endpoints and adds a timed processor helper. Verify error paths, generation handoff, batch isolation, and encoder-only requests.
• tensorrt_llm/serve/perf_metrics.py — Adds request-local timing collection, observer middleware, header formatting/reconstruction, and JSONL export. Verify probe exclusion, concurrent request isolation, and header behavior.
• tests/integration/test_lists/test-db/l0_cpu.yml — Adds three targeted media tests, the OpenAI input-metrics test file, and two input-metrics request tests while retaining two KV-transfer selectors. These entries register the changes for CPU CI.
• tests/unittest/_torch/executor/test_perf_metrics_manager.py — Covers timing callback gates, event readiness and reuse, failures, and rank fanout. The file is included through the unittest/_torch/executor CI entry.
• tests/unittest/_torch/multimodal/test_multimodal_mixin.py — Verifies the encoder context hook runs once across repeated cache lookups. The file is included through the unittest/_torch/multimodal CI entry.
• tests/unittest/executor/test_stats_serializer.py — Covers populated and empty encoder samples and legacy tuple serialization. The file is included through the unittest/executor/test_stats_serializer.py CI entry.
• tests/unittest/llmapi/apps/test_media_io.py — Covers modality timing, failure recording, and process-pool picklability. Three targeted test functions are listed in CPU CI.
• tests/unittest/llmapi/apps/test_openai_input_metrics.py — Covers processor timing, errors, disabled timing, route registration, endpoint totals, and batch isolation. The test file is listed in CPU CI.
• tests/unittest/llmapi/apps/test_request_metrics.py — Covers header, disaggregation, JSONL, and request-local timing behavior. Two existing KV-transfer selectors and two new input-metrics selectors are listed in CPU CI.
• tests/unittest/metrics/test_collector.py — Covers encoder, input-stage, queue, and per-modality histogram observations. The file is included through the unittest/metrics CI entry.